-
Notifications
You must be signed in to change notification settings - Fork 311
Prevent crash in SQL Server's JDBC when tracing execute methods with generated keys #9321
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: master
Are you sure you want to change the base?
Prevent crash in SQL Server's JDBC when tracing execute methods with generated keys #9321
Conversation
0a8f95f
to
eebbd7e
Compare
Code coverage: total 57.30%, base diff -0.03%, patch 100.00% (view details) This comment will be updated automatically if new data arrives.🔗 Commit SHA: 3a324e0 | Docs | Was this helpful? Give us feedback! |
BenchmarksStartupParameters
See matching parameters
SummaryFound 0 performance improvements and 0 performance regressions! Performance is the same for 48 metrics, 11 unstable metrics. Startup time reports for insecure-bankgantt
title insecure-bank - global startup overhead: candidate=1.53.0-SNAPSHOT~3a324e0a0e, baseline=1.53.0-SNAPSHOT~65b2349214
dateFormat X
axisFormat %s
section tracing
Agent [baseline] (1.048 s) : 0, 1048084
Total [baseline] (8.567 s) : 0, 8566564
Agent [candidate] (1.043 s) : 0, 1043119
Total [candidate] (8.599 s) : 0, 8598733
section iast
Agent [baseline] (1.183 s) : 0, 1182839
Total [baseline] (9.289 s) : 0, 9288660
Agent [candidate] (1.177 s) : 0, 1176892
Total [candidate] (9.324 s) : 0, 9323999
gantt
title insecure-bank - break down per module: candidate=1.53.0-SNAPSHOT~3a324e0a0e, baseline=1.53.0-SNAPSHOT~65b2349214
dateFormat X
axisFormat %s
section tracing
crashtracking [baseline] (1.431 ms) : 0, 1431
crashtracking [candidate] (1.422 ms) : 0, 1422
BytebuddyAgent [baseline] (734.321 ms) : 0, 734321
BytebuddyAgent [candidate] (729.872 ms) : 0, 729872
GlobalTracer [baseline] (242.444 ms) : 0, 242444
GlobalTracer [candidate] (241.362 ms) : 0, 241362
AppSec [baseline] (30.173 ms) : 0, 30173
AppSec [candidate] (30.156 ms) : 0, 30156
Debugger [baseline] (6.023 ms) : 0, 6023
Debugger [candidate] (6.034 ms) : 0, 6034
Remote Config [baseline] (655.612 µs) : 0, 656
Remote Config [candidate] (653.434 µs) : 0, 653
Telemetry [baseline] (12.048 ms) : 0, 12048
Telemetry [candidate] (12.806 ms) : 0, 12806
section iast
crashtracking [baseline] (1.429 ms) : 0, 1429
crashtracking [candidate] (1.431 ms) : 0, 1431
BytebuddyAgent [baseline] (854.561 ms) : 0, 854561
BytebuddyAgent [candidate] (849.772 ms) : 0, 849772
GlobalTracer [baseline] (233.252 ms) : 0, 233252
GlobalTracer [candidate] (232.712 ms) : 0, 232712
AppSec [baseline] (25.424 ms) : 0, 25424
AppSec [candidate] (27.415 ms) : 0, 27415
Debugger [baseline] (9.863 ms) : 0, 9863
Debugger [candidate] (7.398 ms) : 0, 7398
Remote Config [baseline] (590.551 µs) : 0, 591
Remote Config [candidate] (576.099 µs) : 0, 576
Telemetry [baseline] (8.33 ms) : 0, 8330
Telemetry [candidate] (8.278 ms) : 0, 8278
IAST [baseline] (28.42 ms) : 0, 28420
IAST [candidate] (28.41 ms) : 0, 28410
Startup time reports for petclinicgantt
title petclinic - global startup overhead: candidate=1.53.0-SNAPSHOT~3a324e0a0e, baseline=1.53.0-SNAPSHOT~65b2349214
dateFormat X
axisFormat %s
section tracing
Agent [baseline] (1.055 s) : 0, 1055460
Total [baseline] (10.753 s) : 0, 10752750
Agent [candidate] (1.042 s) : 0, 1042267
Total [candidate] (10.632 s) : 0, 10632125
section appsec
Agent [baseline] (1.219 s) : 0, 1218564
Total [baseline] (10.749 s) : 0, 10748529
Agent [candidate] (1.223 s) : 0, 1223048
Total [candidate] (10.773 s) : 0, 10773045
section iast
Agent [baseline] (1.185 s) : 0, 1185022
Total [baseline] (10.897 s) : 0, 10896563
Agent [candidate] (1.176 s) : 0, 1175553
Total [candidate] (10.93 s) : 0, 10929753
section profiling
Agent [baseline] (1.208 s) : 0, 1208332
Total [baseline] (10.903 s) : 0, 10902895
Agent [candidate] (1.193 s) : 0, 1192555
Total [candidate] (10.931 s) : 0, 10930665
gantt
title petclinic - break down per module: candidate=1.53.0-SNAPSHOT~3a324e0a0e, baseline=1.53.0-SNAPSHOT~65b2349214
dateFormat X
axisFormat %s
section tracing
crashtracking [baseline] (1.443 ms) : 0, 1443
crashtracking [candidate] (1.429 ms) : 0, 1429
BytebuddyAgent [baseline] (740.142 ms) : 0, 740142
BytebuddyAgent [candidate] (729.325 ms) : 0, 729325
GlobalTracer [baseline] (244.063 ms) : 0, 244063
GlobalTracer [candidate] (241.191 ms) : 0, 241191
AppSec [baseline] (30.476 ms) : 0, 30476
AppSec [candidate] (29.973 ms) : 0, 29973
Debugger [baseline] (6.065 ms) : 0, 6065
Debugger [candidate] (6.008 ms) : 0, 6008
Remote Config [baseline] (659.223 µs) : 0, 659
Remote Config [candidate] (646.17 µs) : 0, 646
Telemetry [baseline] (11.436 ms) : 0, 11436
Telemetry [candidate] (12.785 ms) : 0, 12785
section appsec
crashtracking [baseline] (1.421 ms) : 0, 1421
crashtracking [candidate] (1.436 ms) : 0, 1436
BytebuddyAgent [baseline] (753.087 ms) : 0, 753087
BytebuddyAgent [candidate] (757.564 ms) : 0, 757564
GlobalTracer [baseline] (234.419 ms) : 0, 234419
GlobalTracer [candidate] (234.801 ms) : 0, 234801
IAST [baseline] (23.608 ms) : 0, 23608
IAST [candidate] (23.432 ms) : 0, 23432
AppSec [baseline] (168.107 ms) : 0, 168107
AppSec [candidate] (169.281 ms) : 0, 169281
Debugger [baseline] (8.003 ms) : 0, 8003
Debugger [candidate] (5.745 ms) : 0, 5745
Remote Config [baseline] (618.18 µs) : 0, 618
Remote Config [candidate] (623.36 µs) : 0, 623
Telemetry [baseline] (8.313 ms) : 0, 8313
Telemetry [candidate] (9.026 ms) : 0, 9026
section iast
crashtracking [baseline] (1.437 ms) : 0, 1437
crashtracking [candidate] (1.422 ms) : 0, 1422
BytebuddyAgent [baseline] (856.298 ms) : 0, 856298
BytebuddyAgent [candidate] (849.026 ms) : 0, 849026
GlobalTracer [baseline] (234.407 ms) : 0, 234407
GlobalTracer [candidate] (232.137 ms) : 0, 232137
IAST [baseline] (28.556 ms) : 0, 28556
IAST [candidate] (30.6 ms) : 0, 30600
AppSec [baseline] (28.355 ms) : 0, 28355
AppSec [candidate] (25.006 ms) : 0, 25006
Debugger [baseline] (5.782 ms) : 0, 5782
Debugger [candidate] (7.471 ms) : 0, 7471
Remote Config [baseline] (575.763 µs) : 0, 576
Remote Config [candidate] (576.999 µs) : 0, 577
Telemetry [baseline] (8.448 ms) : 0, 8448
Telemetry [candidate] (8.338 ms) : 0, 8338
section profiling
crashtracking [baseline] (1.423 ms) : 0, 1423
crashtracking [candidate] (1.411 ms) : 0, 1411
BytebuddyAgent [baseline] (770.493 ms) : 0, 770493
BytebuddyAgent [candidate] (759.188 ms) : 0, 759188
GlobalTracer [baseline] (224.009 ms) : 0, 224009
GlobalTracer [candidate] (221.922 ms) : 0, 221922
AppSec [baseline] (30.483 ms) : 0, 30483
AppSec [candidate] (29.772 ms) : 0, 29772
Debugger [baseline] (6.278 ms) : 0, 6278
Debugger [candidate] (6.295 ms) : 0, 6295
Remote Config [baseline] (736.921 µs) : 0, 737
Remote Config [candidate] (665.112 µs) : 0, 665
Telemetry [baseline] (16.054 ms) : 0, 16054
Telemetry [candidate] (16.019 ms) : 0, 16019
ProfilingAgent [baseline] (108.763 ms) : 0, 108763
ProfilingAgent [candidate] (107.844 ms) : 0, 107844
Profiling [baseline] (109.431 ms) : 0, 109431
Profiling [candidate] (108.495 ms) : 0, 108495
LoadParameters
See matching parameters
SummaryFound 1 performance improvements and 1 performance regressions! Performance is the same for 10 metrics, 12 unstable metrics.
Request duration reports for petclinicgantt
title petclinic - request duration [CI 0.99] : candidate=1.53.0-SNAPSHOT~3a324e0a0e, baseline=1.53.0-SNAPSHOT~65b2349214
dateFormat X
axisFormat %s
section baseline
no_agent (36.003 ms) : 35717, 36288
. : milestone, 36003,
appsec (47.033 ms) : 46604, 47462
. : milestone, 47033,
code_origins (43.618 ms) : 43242, 43994
. : milestone, 43618,
iast (44.348 ms) : 43961, 44735
. : milestone, 44348,
profiling (50.88 ms) : 50399, 51360
. : milestone, 50880,
tracing (44.582 ms) : 44196, 44968
. : milestone, 44582,
section candidate
no_agent (35.03 ms) : 34756, 35304
. : milestone, 35030,
appsec (48.047 ms) : 47612, 48481
. : milestone, 48047,
code_origins (45.449 ms) : 45053, 45845
. : milestone, 45449,
iast (45.247 ms) : 44864, 45629
. : milestone, 45247,
profiling (49.149 ms) : 48688, 49609
. : milestone, 49149,
tracing (44.612 ms) : 44223, 45002
. : milestone, 44612,
Request duration reports for insecure-bankgantt
title insecure-bank - request duration [CI 0.99] : candidate=1.53.0-SNAPSHOT~3a324e0a0e, baseline=1.53.0-SNAPSHOT~65b2349214
dateFormat X
axisFormat %s
section baseline
no_agent (4.277 ms) : 4229, 4325
. : milestone, 4277,
iast (9.219 ms) : 9066, 9371
. : milestone, 9219,
iast_FULL (13.702 ms) : 13435, 13970
. : milestone, 13702,
iast_GLOBAL (10.156 ms) : 9963, 10349
. : milestone, 10156,
profiling (8.62 ms) : 8480, 8760
. : milestone, 8620,
tracing (7.444 ms) : 7338, 7549
. : milestone, 7444,
section candidate
no_agent (4.287 ms) : 4240, 4334
. : milestone, 4287,
iast (9.348 ms) : 9195, 9501
. : milestone, 9348,
iast_FULL (13.84 ms) : 13563, 14117
. : milestone, 13840,
iast_GLOBAL (10.09 ms) : 9914, 10267
. : milestone, 10090,
profiling (8.756 ms) : 8611, 8902
. : milestone, 8756,
tracing (7.616 ms) : 7508, 7723
. : milestone, 7616,
DacapoParameters
See matching parameters
SummaryFound 0 performance improvements and 0 performance regressions! Performance is the same for 10 metrics, 2 unstable metrics. Execution time for tomcatgantt
title tomcat - execution time [CI 0.99] : candidate=1.53.0-SNAPSHOT~3a324e0a0e, baseline=1.53.0-SNAPSHOT~65b2349214
dateFormat X
axisFormat %s
section baseline
no_agent (1.479 ms) : 1467, 1490
. : milestone, 1479,
appsec (3.658 ms) : 3442, 3875
. : milestone, 3658,
iast (2.206 ms) : 2144, 2269
. : milestone, 2206,
iast_GLOBAL (2.239 ms) : 2176, 2303
. : milestone, 2239,
profiling (2.036 ms) : 1986, 2087
. : milestone, 2036,
tracing (2.018 ms) : 1970, 2067
. : milestone, 2018,
section candidate
no_agent (1.481 ms) : 1469, 1492
. : milestone, 1481,
appsec (3.688 ms) : 3470, 3907
. : milestone, 3688,
iast (2.2 ms) : 2137, 2262
. : milestone, 2200,
iast_GLOBAL (2.252 ms) : 2189, 2316
. : milestone, 2252,
profiling (2.458 ms) : 2301, 2615
. : milestone, 2458,
tracing (2.021 ms) : 1973, 2070
. : milestone, 2021,
Execution time for biojavagantt
title biojava - execution time [CI 0.99] : candidate=1.53.0-SNAPSHOT~3a324e0a0e, baseline=1.53.0-SNAPSHOT~65b2349214
dateFormat X
axisFormat %s
section baseline
no_agent (15.682 s) : 15682000, 15682000
. : milestone, 15682000,
appsec (14.801 s) : 14801000, 14801000
. : milestone, 14801000,
iast (18.551 s) : 18551000, 18551000
. : milestone, 18551000,
iast_GLOBAL (18.074 s) : 18074000, 18074000
. : milestone, 18074000,
profiling (15.452 s) : 15452000, 15452000
. : milestone, 15452000,
tracing (15.037 s) : 15037000, 15037000
. : milestone, 15037000,
section candidate
no_agent (15.688 s) : 15688000, 15688000
. : milestone, 15688000,
appsec (14.74 s) : 14740000, 14740000
. : milestone, 14740000,
iast (18.564 s) : 18564000, 18564000
. : milestone, 18564000,
iast_GLOBAL (18.112 s) : 18112000, 18112000
. : milestone, 18112000,
profiling (15.32 s) : 15320000, 15320000
. : milestone, 15320000,
tracing (15.094 s) : 15094000, 15094000
. : milestone, 15094000,
|
@@ -75,6 +76,7 @@ public static class StatementAdvice { | |||
@Advice.OnMethodEnter(suppress = Throwable.class) | |||
public static AgentScope onEnter( | |||
@Advice.Argument(value = 0, readOnly = false) String sql, | |||
@Advice.AllArguments(typing = DYNAMIC) Object[] args, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I've decided to use AllArguments here, because some of the execute
methods we are hooking accepts an int for the generatedKeys
, while others accept an array of ints for columnIndexes
or and array of strings for columnNames
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
getting byte-buddy to pack all arguments into an array could affect performance - have you done any benchmarking of this?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
An alternative approach that would avoid this would be to write different advices for the different method signatures - you can still share code between the advices by moving that code to the decorator (or similar helper)
While this would take longer to write, it would be much more performant... also you'd only write the code once while this advice will be invoked many millions of time
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
FYI, I did some benchmarking with an existing setup and the overhead is minor
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@na-ji btw, is the typing = DYNAMIC
needed?
I found a couple of existing instrumentations that use @Advice.AllArguments
and they don't need typing = DYNAMIC
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
An alternative approach that would avoid this would be to write different advices for the different method signatures - you can still share code between the advices by moving that code to the decorator (or similar helper)
While this would take longer to write, it would be much more performant... also you'd only write the code once while this advice will be invoked many millions of time
Yes, this was my plan if I could not do a single advice with AllArguments. I totally didn't thought of the performance impact though. Thanks for testing!
@na-ji btw, is the
typing = DYNAMIC
needed?I found a couple of existing instrumentations that use
@Advice.AllArguments
and they don't needtyping = DYNAMIC
When I was first starting, I encountered some errors from byte buddy telling me that I should use dynamic typing. I just removed it and it's still working. I don't know what impact it has.
TBH, I found byte buddy confusing with a lacking documentation, even though I have experience manipulating Java objects in smali or with Frida.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm wary about the change to add
@Advice.AllArguments(typing = DYNAMIC) Object[] args
and would prefer to see this covered by more focused advice, because that would avoid the additional byte-buddy allocation of an array to hold all the arguments and copying them in individually - this is a hot method and additional allocations could easily affect latency.
But if a benchmark of a DB application being traced before this change and after doesn't show any difference then I'm ok with this change (I'd just like to get confirmation of that)
Also :dd-java-agent:instrumentation:jdbc:forkedTest
is failing on CI for this branch - that needs fixing before this could be merged and backported
I did some benchmarking with an existing setup and the overhead is minor.
So it's just the :dd-java-agent:instrumentation:jdbc:forkedTest
that needs fixing
…nerated keys When tracing the JDBC statement execute methods, we prepend a comment to the SQL query used for DBM trace propagation. However, there is a bug in the SQL Server JDBC driver that prevents the generated keys from being returned when the SQL comment is prepended to the SQL query. I decided to only append the comment in this specific case to avoid the comment from being truncated. @see microsoft/mssql-jdbc#2729
8c3f56e
to
e84d9eb
Compare
@@ -127,6 +128,21 @@ public static AgentScope onEnter( | |||
// context_info and v$session.action respectively. | |||
// we should not also inject it into SQL comments to avoid duplication | |||
final boolean injectTraceInComment = injectTraceContext && !isSqlServer && !isOracle; | |||
|
|||
boolean appendComment = StatementInstrumentation.appendComment; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Advice should not depend on the instrumentation class, because the advice bytecode will be lifted and injtected into the class that lives in the application class-loader. This happens to work here because StatementInstrumentation.appendComment
is a constant which gets inlined by javac
, but we should not rely on this. If someone ever changed StatementInstrumentation.appendComment
to not be a constant then this advice would break and users would lose JDBC traces.
Can you remove StatementInstrumentation.appendComment
from the surrounding class and replace its use here by the literal value false
.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
To be fair, I don't really understand why we have this constant on this class. It used to be used here, and but its type was final static so it wasn't really useful.
What Does This Do
Modify the way we append/prepend the DBM tracing comment into queries.
Motivation
When tracing the JDBC statement execute methods, we prepend a comment to the SQL query used for DBM trace propagation.
However, there is a bug in the SQL Server JDBC driver that prevents the generated keys from being returned when the SQL comment is prepended to the SQL query.
I decided to only append the comment in this specific case to avoid the comment from being truncated.
See microsoft/mssql-jdbc#2729
Additional Notes
This is the code that used to crash on the injected app when DBM trace propagation was enabled
Contributor Checklist
type:
and (comp:
orinst:
) labels in addition to any usefull labelsclose
,fix
or any linking keywords when referencing an issue.Use
solves
instead, and assign the PR milestone to the issueJira ticket: [PROJ-IDENT]